Skip to content

feat: per-step progress logging for the multi-start gradient searches - #1435

Merged
Jammy2211 merged 1 commit into
mainfrom
feature/multi-start-gradient-progress-logging
Jul 30, 2026
Merged

feat: per-step progress logging for the multi-start gradient searches#1435
Jammy2211 merged 1 commit into
mainfrom
feature/multi-start-gradient-progress-logging

Conversation

@Jammy2211

Copy link
Copy Markdown
Collaborator

Summary

Closes #1433.

af.MultiStartProdigy / MultiStartAdam / MultiStartADABelief / MultiStartLion emitted exactly two log lines for an entire run — "Starting new <rule> MultiStartGradient search (N starts, ...)" and, however many hours later, "<rule> MultiStartGradient sampling complete." Nothing in between, so a user could not tell a live 300-step fit from a hung one.

Neither of the framework's usual progress channels reaches this search, which is why it needs its own:

  • iterations_per_full_update defaults to the never-sentinel, so the whole run is a single chunk whose lone perform_update is (correctly) suppressed by _is_final_boundary as duplicated work.
  • Fitness's quick-update counter is Python state mutated inside fitness.call, which this search traces under jax.jit(jax.vmap(…)) — it runs once at trace time and never again.

The samplers dodge the problem by delegating to their own library's progress bar (emcee progress=True, dynesty print_progress); a search that owns its step loop has to report for itself.

This adds a cadence-controlled progress line plus two JAX-compile notices, all gated on the existing silence flag.

Why a log line and not a progress bar: tqdm is only a transitive dependency, auto-convergence makes n_steps a ceiling the search routinely stops short of (so a bar's ETA would mislead), and lines survive SLURM/HPC log capture where bars do not.

Why the compile notices live here: the compile-message work in #1434 targets Fitness._jit / _vmap / _grad, which these searches never use — they build their transforms straight off fitness.call (search.py:260-261). Without this, that fix would ship and these searches would still sit through their compile in silence. Two distinct compiles block a fresh run and both are covered: the single-point objective _broad_starts calls per draw, and the vmapped/chunked one the step loop calls. Wording is matched to #1434 rather than inventing a second dialect.

API Changes

One additive, default-preserving constructor argument on AbstractMultiStartGradient, inherited by all four concrete searches: iterations_per_log: int = 10. No existing signature, default or behaviour changes, and no symbol is removed or renamed — a caller that ignores it sees identical results, only new log output.

See full details below.

Test Plan

  • Full library suite: python -m pytest test_autofit/1614 passed, 1 skipped
  • New NumPy-only unit tests (22) for the cadence rule, the message formatting, the sign convention, the non-finite edges, the compile notices, dict round-trip, and a source-level wiring guard
  • Real JAX MultiStartProdigy fit on the 1D Gaussian, confirming the lines fire in a live run (output below)
  • Diff is pure additions — 373 insertions, 0 deletions

Real run (n_starts=16, n_steps=120, iterations_per_log=10):

21:39:32,209 - INFO - JAX: jit compiling the single-point objective used to draw 16 broad starts, could take seconds or minutes...
21:39:34,390 - INFO - Starting new prodigy MultiStartGradient search (16 starts, no previous samples found).
21:39:34,390 - INFO - JAX: jit compiling the vmapped objective over all 16 starts at once, could take seconds or minutes...
21:39:36,614 - INFO - prodigy step 1/120 | best log_post -3335.7342 | alive 16/16 | d 1.00e-06 / 1.00e-06 / 1.00e-06
21:39:36,641 - INFO - prodigy step 10/120 | best log_post -3335.7291 | gained 0.0051 | alive 16/16 | d 1.73e-05 / 1.73e-05 / 1.73e-05
21:39:36,679 - INFO - prodigy step 20/120 | best log_post -3335.4641 | gained 0.2649 | alive 16/16 | d 8.99e-04 / 8.99e-04 / 8.99e-04
21:39:36,706 - INFO - prodigy step 30/120 | best log_post -3318.1027 | gained 17.3614 | alive 16/16 | d 5.91e-02 / 5.92e-02 / 5.93e-02
21:39:36,735 - INFO - prodigy step 40/120 | best log_post -1743.4656 | gained 1574.6372 | alive 15/16 | d 2.56e+00 / 4.86e+00 / 5.07e+00
21:39:36,760 - INFO - prodigy step 50/120 | best log_post -171.4357 | gained 1572.0299 | alive 14/16 | d 2.56e+00 / 7.70e+00 / 1.19e+01
...
21:39:36,911 - INFO - prodigy step 120/120 | best log_post -58.8587 | gained 0.0647 | alive 16/16 | d 2.56e+00 / 7.70e+00 / 1.19e+01
21:39:36,916 - INFO - prodigy MultiStartGradient sampling complete.

Note the two compiles account for ~4.4s while all 120 steps take 0.3s — on this toy problem the compile is the wait, which is exactly why it needed a notice. The d (Prodigy's estim_lr) column ramps 1e-06 → 1.19e+01 while the fit is still finding its basin, then plateaus: previously invisible, and the one genuinely learning-rate-free diagnostic.

Notes for review

  • The knob lands on AbstractMultiStartGradient, so all four subclasses get the line — the silence was a base-class problem, not a Prodigy-only one.
  • No new packaged config key. A key added to the shared updates: block would imply every search honours it (they don't) and would KeyError in any workspace whose config shadows that section — the trap hit in feat(autofit): multi-start gradient convergence results contract (phase 2) #1409. A plain constructor kwarg avoids both.
  • No XLA recompile and no new sync. The step loop already forces a device sync every step at search.py:361 (np.isfinite(np.asarray(foms))), so the step/fom/alive fields are free. estim_lr is an (n_starts,) device→host copy taken only on a logging step, which merely pulls forward the sync the next iteration would force anyway. Nothing traced is added.
  • Ships alongside fix: sampler CLI prints variable name, JAX compile msg fires early #1434, which is concurrently claimed on PyAutoFit but touches disjoint files (abstract_search.py / fitness.py). Branched off the same a50ba95b0; origin/main had not moved at PR-open.
Full API Changes (for automation & release notes)

Added

  • AbstractMultiStartGradient.__init__(..., iterations_per_log: int = 10) — steps between progress lines on the search log. Inherited by MultiStartAdam, MultiStartADABelief, MultiStartLion and MultiStartProdigy. Serialised through to_dict/from_dict, so a resumed search keeps the chosen cadence. Rejected at construction (via AbstractSearch._check_step_count) if not a whole number ≥ 1, since a sub-1 cadence either raises on the modulo or logs every step.

Changed Behaviour

  • The four multi-start gradient searches now emit progress output during _fit, where previously they were silent between start and completion. Emitted at logging.INFO on the search's own logger and fully suppressed by the existing silence=True; numerical results are unchanged.

Migration

None required — the argument is optional and defaults to the new behaviour. Pass silence=True for the previous, fully-silent output.

Generated by the PyAutoLabs agent workflow.

The MultiStartGradient searches emitted two log lines for an entire run --
"Starting new ..." and "... sampling complete" -- leaving a user unable to tell
a live fit from a hung one. Neither of the framework's progress channels reaches
them: iterations_per_full_update makes the whole run a single chunk whose lone
perform_update is (correctly) suppressed as duplicated work, and Fitness's
quick-update counter is Python state mutated inside fitness.call, which these
searches trace under jax.jit(jax.vmap(...)) -- so it runs once at trace time and
never again. The samplers delegate to their own library's progress bar; a search
that owns its step loop has to report for itself.

Adds iterations_per_log (default 10) on AbstractMultiStartGradient, inherited by
all four concrete searches. The line reports step, best log posterior, gain since
the last line and live-start count, plus Prodigy's estim_lr -- its self-estimated
step scale -- where the rule carries one. The first step always logs, since that
line is what tells the user the XLA compile finished and stepping has begun.

Two JAX-compile notices cover the single-point objective _broad_starts calls per
draw and the vmapped/chunked one the step loop calls. Neither is reachable by the
Fitness._jit/_vmap/_grad notices, because this search builds its transforms
straight off fitness.call.

All output is gated on the existing silence flag. Numerically inert: no traced
operation is added, and the loop already forced a device sync every step.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Unu8t9xqScV93XinRmx1Do
@Jammy2211 Jammy2211 added the pending-release PR queued for the next release build label Jul 30, 2026
@Jammy2211
Jammy2211 merged commit 09a134d into main Jul 30, 2026
3 checks passed
@Jammy2211
Jammy2211 deleted the feature/multi-start-gradient-progress-logging branch July 30, 2026 21:53
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

pending-release PR queued for the next release build

Projects

None yet

Development

Successfully merging this pull request may close these issues.

feat: per-step progress logging for the multi-start gradient searches

1 participant